search

hyperhq / hyperstart

The tiny Init service for HyperContainer
https://www.hypercontainer.io
Apache License 2.0
134 stars 63 forks source link

failed to build #131

Closed keyolk closed 7 years ago

keyolk commented 8 years ago

Hello all, I'm newbie on this project. and I got below error on build time.

$ make make all-recursive make[1]: Entering directory '/home/keyolk/.gvm/pkgsets/go1.6.2/container/src/github.com/hyperhq/hyperstart' Making all in src make[2]: Entering directory '/home/keyolk/.gvm/pkgsets/go1.6.2/container/src/github.com/hyperhq/hyperstart/src' make[2]: Nothing to be done for 'all'. make[2]: Leaving directory '/home/keyolk/.gvm/pkgsets/go1.6.2/container/src/github.com/hyperhq/hyperstart/src' Making all in build make: relocation error: libm.so.6: symbol __get_cpu_features, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference make[1]: * [Makefile:352: all-recursive] Error 1 make[1]: Leaving directory '/home/keyolk/.gvm/pkgsets/go1.6.2/container/src/github.com/hyperhq/hyperstart' make: * [Makefile:293: all] Error 2

$ objdump -T /usr/lib/libc.so.6 | grep GLIBC_PRIVATE | grep cpu 00000000000f4300 g DF .text 0000000000000036 GLIBC_PRIVATE __clock_getcpuclockid

to solve this, is there any something workaround ?

gao-feng commented 8 years ago

Hello, What's the result of ldd src/init?

laijs commented 8 years ago

could you retry it with a small workaround

diff --git a/build/make-initrd.sh b/build/make-initrd.sh
index 13872c6..2f0cf15 100755
--- a/build/make-initrd.sh
+++ b/build/make-initrd.sh
@@ -5,8 +5,6 @@ mkdir -p /tmp/hyperstart-rootfs/lib /tmp/hyperstart-rootfs/lib64 /tmp/hyperstart

 cp ../src/init /tmp/hyperstart-rootfs
 cp busybox /tmp/hyperstart-rootfs
-cp iptables /tmp/hyperstart-rootfs
-cp libm.so.6 /tmp/hyperstart-rootfs/lib64/
 tar -xf modules.tar -C /tmp/hyperstart-rootfs/lib/modules

 ldd /tmp/hyperstart-rootfs/init | while read line
keyolk commented 8 years ago

@gao-feng here my results of ldd $ pwd /home/keyolk/workspace/projects/container/src/github.com/hyperhq/hyperstart $ ldd src/init
linux-vdso.so.1 (0x00007ffdee5e1000) libc.so.6 => /usr/lib/libc.so.6 (0x00007fbc340dc000) /lib64/ld-linux-x86-64.so.2 (0x00007fbc3447d000)

@laijs I removed the lines but nothing changed

$ git diff diff --git a/build/make-initrd.sh b/build/make-initrd.sh index 13872c6..2f0cf15 100755 --- a/build/make-initrd.sh +++ b/build/make-initrd.sh @@ -5,8 +5,6 @@ mkdir -p /tmp/hyperstart-rootfs/lib /tmp/hyperstart-rootfs/lib64 /tmp/hyperstart

cp ../src/init /tmp/hyperstart-rootfs cp busybox /tmp/hyperstart-rootfs -cp iptables /tmp/hyperstart-rootfs -cp libm.so.6 /tmp/hyperstart-rootfs/lib64/ tar -xf modules.tar -C /tmp/hyperstart-rootfs/lib/modules

ldd /tmp/hyperstart-rootfs/init | while read line

$ make
make all-recursive make[1]: Entering directory '/home/keyolk/.gvm/pkgsets/go1.6.2/container/src/github.com/hyperhq/hyperstart' Making all in src make[2]: Entering directory '/home/keyolk/.gvm/pkgsets/go1.6.2/container/src/github.com/hyperhq/hyperstart/src' make[2]: Nothing to be done for 'all'. make[2]: Leaving directory '/home/keyolk/.gvm/pkgsets/go1.6.2/container/src/github.com/hyperhq/hyperstart/src' Making all in build make: relocation error: libm.so.6: symbol __get_cpu_features, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference make[1]: * [Makefile:352: all-recursive] Error 1 make[1]: Leaving directory '/home/keyolk/.gvm/pkgsets/go1.6.2/container/src/github.com/hyperhq/hyperstart' make: * [Makefile:293: all] Error 2

laijs commented 8 years ago

./autogen.sh & ./configure are needed after the patch

keyolk commented 8 years ago

@laijs Ofcourse I did : (

I also tried remove repository, change the diffs ./autogen.sh ./configure make

but same make: relocation error: libm.so.6: symbol __get_cpu_features, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

above log again : D

gao-feng commented 8 years ago

Well, We already have init(hyperstart), Would you like to generate initrd.img manually? You can get it through below commands line

mkdir -p /tmp/hyperstart-rootfs/lib/modules mkdir -p /tmp/hyperstart-rootfs/usr/lib cp src/init /tmp/hyperstart-rootfs cp /usr/lib/libc.so.6 /tmp/hyperstart-rootfs/usr/lib/ cp build/busybox /tmp/hyperstart-rootfs tar -xf build/modules.tar -C /tmp/hyperstart-rootfs/lib/modules cd /tmp/hyperstart-rootfs && find . | cpio -H newc -o | gzip -9 > /tmp/hyper-initrd.img

this will also clearly tell us which step cause the version GLIBC_PRIVATE not defined problem. Thanks!

laijs commented 8 years ago

we don't have "Apricity OS" it is strange that libm.so is being linked("with link time reference") when "make".

keyolk commented 8 years ago

@gao-feng What I wanted do is just run runv/hyper with virtualbox. And I did your suggestions but runv failed to start

error rpc error: code = 2 desc = StartPod fail

and there is no proper logs under /var/log/hyper/qemu/ below is only log I can get

Log file created at: 2016/07/13 16:56:46 Running on machine: keyolk-book Binary: Built with gc go1.6.2 for linux/amd64 Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg

@laijs Actually it is almost same to archlinux : D

gao-feng commented 8 years ago

Can you show config.json in bundle?

below is command line in my env:

/home/gaofeng/go/src/github.com/hyperhq/runv/runv --kernel /home/gaofeng/git/hyperstart/build/kernel --initrd /home/gaofeng/git/hyperstart/build/hyper-initrd.img  --debug --driver qemu start -b /root/test-runv/busybox/ busybox

and config.json of busybox bundle is

{
    "version": "0.2.0",
    "platform": {
        "os": "linux",
        "arch": "amd64"
    },
    "process": {
        "terminal": true,
        "user": {
            "uid": 0,
            "gid": 0,
            "additionalGids": null
        },
        "args": [
            "sh"
        ],
        "env": [
            "PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
            "TERM=xterm"
        ],
        "cwd": ""
    },
    "root": {
        "path": "rootfs",
        "readonly": true
    },
    "hostname": "shell",
    "mounts": null
}
keyolk commented 8 years ago

below is my config.json is generated by runv spec . and I uses tomcat image as a bundle

{
        "ociVersion": "0.5.0-dev",
        "platform": {
                "os": "linux",
                "arch": "amd64"
        },
        "process": {
                "terminal": true,
                "user": {},
                "args": [
                        "sh"
                ],
                "env": [
                        "PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
                        "TERM=xterm"
                ],
                "cwd": ""
        },
        "root": {
                "path": "rootfs",
                "readonly": true
        },
        "hostname": "shell",
        "mounts": null,
        "hooks": {},
        "linux": {
                "resources": {
                        "devices": null
                }
        }
}
gao-feng commented 8 years ago

Does hyperd & hyperctl works well?

Can you try the below patch in runv? this will flush logs out.

$ git diff
diff --git a/Godeps/_workspace/src/github.com/golang/glog/glog.go b/Godeps/_workspace/src/github.com/golang/glog/glog.go
index 54bd7af..2a931c5 100644
--- a/Godeps/_workspace/src/github.com/golang/glog/glog.go
+++ b/Godeps/_workspace/src/github.com/golang/glog/glog.go
@@ -732,6 +732,7 @@ func (l *loggingT) output(s severity, buf *buffer, file string, line int, alsoTo
                os.Exit(255) // C++ uses -1, which is silly because it's anded with 255 anyway.
        }
        l.putBuffer(buf)
+       l.flushAll()
        l.mu.Unlock()
        if stats := severityStats[s]; stats != nil {
                atomic.AddInt64(&stats.lines, 1)
keyolk commented 8 years ago

@gao-feng
Thank your advice below is from my laptop

after put the patch on runv,

diff --git a/Godeps/_workspace/src/github.com/golang/glog/glog.go b/Godeps/_workspace/src/github.com/golang/glog/glog.go
index 54bd7af..63525d0 100644
--- a/Godeps/_workspace/src/github.com/golang/glog/glog.go
+++ b/Godeps/_workspace/src/github.com/golang/glog/glog.go
@@ -732,6 +732,7 @@ func (l *loggingT) output(s severity, buf *buffer, file string, line int, alsoTo
                os.Exit(255) // C++ uses -1, which is silly because it's anded with 255 anyway.
        }
        l.putBuffer(buf)
+  l.flushAll()
        l.mu.Unlock()
        if stats := severityStats[s]; stats != nil {
                atomic.AddInt64(&stats.lines, 1)

I did

$ ./autogen
$ ./configure
$ make
$ sudo make install

then

$ sudo hyperctl run -d tomcat
POD id is pod-iSDrBaMvhb
hyperctl ERROR: Error from daemon's response: VM vm-UXmYNOhmeG start failed with code 7: Start POD failed

from hyperd log

E0714 10:26:23.997572   19401 vm_states.go:278] Shutting down because of an exception: Start POD failed
E0714 10:26:23.997794   19401 vm_states.go:518] Start POD failed
I0714 10:26:23.997803   19401 init_comm.go:190] got cmd:4
E0714 10:26:23.997846   19401 run.go:77] VM vm-UXmYNOhmeG start failed with code 7: Start POD failed
E0714 10:26:23.997857   19401 server.go:170] Handler for POST /v0.6.0/pod/start returned error: VM vm-UXmYNOhmeG start failed with code 7: Start POD failed
I0714 10:26:23.999147   19401 init_comm.go:190] got cmd:14
I0714 10:26:23.999800   19401 init_comm.go:190] got cmd:14
I0714 10:26:24.000506   19401 init_comm.go:190] got cmd:9
I0714 10:26:24.000519   19401 init_comm.go:194] got response of shutdown command, last round of command to init
I0714 10:26:24.000531   19401 vm_states.go:635] POD destroyed 
I0714 10:26:24.000541   19401 qmp_handler.go:296] got new session
I0714 10:26:24.000846   19401 qmp_handler.go:152] Shutdown, quit QMP receiver
I0714 10:26:24.000870   19401 qmp_handler.go:325] got QMP shutdown event, quit...
I0714 10:26:24.000885   19401 vm_states.go:617] Got VM shutdown event while terminating, go to cleaning up
E0714 10:26:24.052125   19401 tty.go:92] read tty data failed
E0714 10:26:24.052125   19401 init_comm.go:99] read init data failed
.
├── hyperd.ERROR -> hyperd.keyolk-book.root.log.ERROR.20160714-102623.19401
├── hyperd.INFO -> hyperd.keyolk-book.root.log.INFO.20160714-102608.19401
├── hyperd.keyolk-book.root.log.ERROR.20160714-102623.19401
├── hyperd.keyolk-book.root.log.INFO.20160714-102608.19401
├── hyperd.keyolk-book.root.log.WARNING.20160714-102623.19401
├── hyperd.WARNING -> hyperd.keyolk-book.root.log.WARNING.20160714-102623.19401
└── qemu
    └── vm-UXmYNOhmeG.log

1 directory, 7 files

from above no contents in the log under qemu and no something special logs is there I guess. and before above process, I copied the initrd.img I built to /var/lib/hyper/hyper-initrd.img

keyolk commented 8 years ago

@laijs and I found that the symbol __get_cpu_features is moved to ld-linux-x86-64.so.2

$ nm ld-linux-x86-64.so.2 | grep __get_cpu_
0000000000016f80 T __get_cpu_features
laijs commented 8 years ago

but from whom are libm.so referenced ?

keyolk commented 8 years ago

@laijs well... no idea so far anyway if I just remove the file and after applying your patch it built well.

but still hyperd/hyperctl put same error

E0714 14:26:39.700963 21882 vm_states.go:278] Shutting down because of an exception: Start POD failed

keyolk commented 8 years ago

@laijs but in case of ctr I succeed to get running VM. but still I can exec any of process

$ sudo ctr --address=$CONTAINERD_SOCK containers start test `pwd`
ID                  PATH                           STATUS              PROCESSES
test                /home/keyolk/workspace/hyper   running             init

$ sudo ctr --address=$CONTAINERD_SOCK containers exec --id=test --pid=100 --cwd=/ -a ps aux
$

below is log from runv-containerd

I0714 14:35:25.303698    8265 process.go:33] process setupIO: stdin /tmp/ctr-624094781/stdin, stdout /tmp/ctr-624094781/stdout, stderr /tmp/ctr-624094781/stderr
I0714 14:35:25.308395    8265 process.go:61] process setupIO() success
I0714 14:35:25.312492    8265 events.go:121] notifySubscribers: {test start-process 2016-07-14 14:35:25.312487431 +0900 KST 100 0}
I0714 14:35:25.314964    8265 hypervisor.go:29] vm vm-WrgZYYomSG: main event loop got message 34(GENERIC_OPERATION)
I0714 14:35:25.319182    8265 vm_states.go:296] handle GenericOperation(AddProcess) on state(RUNNING)
I0714 14:35:25.322446    8265 init_comm.go:190] got cmd:6
I0714 14:35:25.325099    8265 init_comm.go:281] send command 6 to init, payload: '{"container":"test","process":{"terminal":false,"stdio":3,"stderr":4,"args":["ps","aux"],"workdir":"/"}}'.
I0714 14:35:25.330068    8265 init_comm.go:294] write 112 to init, payload: 'p{"container":"test","process":{"terminal":false,"stdio":3,"stderr":4,"args":["ps","aux"],"workdir":"/"}}'.
I0714 14:35:25.332052    8265 init_comm.go:299] message sent, set pong timer
I0714 14:35:25.330517    8265 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0714 14:35:25.340172    8265 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x61ba80, fd 3. ops 0x61b860
I0714 14:35:25.343574    8265 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x61ba80, fd 3, 0x61b860
I0714 14:35:25.346948    8265 init_comm.go:68] [console] hyper_event_read
I0714 14:35:25.350377    8265 init_comm.go:68] [console] already read 8 bytes data
I0714 14:35:25.353861    8265 init_comm.go:68] [console] hyper send type 14, len 4
I0714 14:35:25.355735    8265 init_comm.go:68] [console] get length 112
I0714 14:35:25.360503    8265 init_comm.go:68] [console] read 104 bytes data, total data 112
I0714 14:35:25.362791    8265 init_comm.go:68] [console] hyper send type 14, len 4
I0714 14:35:25.364527    8265 init_comm.go:68] [console] 0 0 0 6 0 0 0 70 7b 22 63 6f 6e 74 61 69 6e 65 72 22 3a 22 74 65 73 74 22 2c 22 70 72 6f 63 65 73 73 22 3a 7b 22 74 65 72 6d 69 6e 61 6c 22 3a 66 61 6c 73
 65 2c 22 73 74 64 69 6f 22 3a 33 2c 22 73 74 64 65 72 72 22 3a 34 2c 22 61 72 67 73 22 3a 5b 22 70 73 22 2c 22 61 75 78 22 5d 2c 22 77 6f 72 6b 64 69 72 22 3a 22 2f 22 7d 7d 
I0714 14:35:25.366205    8265 init_comm.go:68] [console]  hyper_channel_handle, type 6, len 112
I0714 14:35:25.367992    8265 init_comm.go:68] [console] call hyper_exec_cmd, json {"container":"test","process":{"terminal":false,"stdio":3,"stderr":4,"args":["ps","aux"],"workdir":"/"}} , len 104
I0714 14:35:25.371386    8265 init_comm.go:68] [console] jsmn parse failed, n is -1
I0714 14:35:25.375028    8265 init_comm.go:68] [console] get container test
I0714 14:35:25.378353    8265 init_comm.go:68] [console] 1 name terminal
I0714 14:35:25.383098    8265 init_comm.go:68] [console] container doesn't use terminal
I0714 14:35:25.385255    8265 init_comm.go:68] [console] 3 name stdio
I0714 14:35:25.387476    8265 init_comm.go:68] [console] container seq 3
I0714 14:35:25.392325    8265 init_comm.go:68] [console] 5 name stderr
I0714 14:35:25.394327    8265 init_comm.go:68] [console] container stderr seq 4
I0714 14:35:25.395919    8265 init_comm.go:68] [console] 7 name args
I0714 14:35:25.397474    8265 init_comm.go:68] [console] container init arg 0 ps
I0714 14:35:25.399257    8265 init_comm.go:68] [console] container init arg 1 aux
I0714 14:35:25.403945    8265 init_comm.go:68] [console] 11 name workdir
I0714 14:35:25.407400    8265 init_comm.go:68] [console] container workdir /
I0714 14:35:25.410860    8265 init_comm.go:68] [console] hyper_init_event container pts event 0x18461b0, ops 0x61b9c0, fd 7
I0714 14:35:25.415522    8265 init_comm.go:68] [console] hyper_add_event add event fd 7, 0x61b9c0
I0714 14:35:25.417406    8265 init_comm.go:68] [console] hyper_add_event add event fd 8, 0x61b980
I0714 14:35:25.419900    8265 init_comm.go:68] [console] hyper_add_event add event fd 10, 0x61b940
I0714 14:35:25.424660    8265 init_comm.go:68] [console] do_exec_cmd pid 331
I0714 14:35:25.426677    8265 init_comm.go:68] [console] create exec cmd ps pid 332,ref 4
I0714 14:35:25.428397    8265 init_comm.go:68] [console] hyper send type 332, len 0                                                                                                                        [29/667]
I0714 14:35:25.430052    8265 init_comm.go:68] [console] hyper_run_process get ready message 332
I0714 14:35:25.431927    8265 init_comm.go:68] [console] hyper send type 9, len 0
I0714 14:35:25.436505    8265 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0714 14:35:25.441369    8265 init_comm.go:68] [console] hyper_handle_event get event 4, de 0x18461b0, fd 7. ops 0x61b9c0
I0714 14:35:25.443614    8265 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, de 0x18461b0, fd 7, 0x61b9c0
I0714 14:35:25.448189    8265 init_comm.go:68] [console] write_to_stdin, seq 3
I0714 14:35:25.450054    8265 init_comm.go:68] [console] hyper_modify_event modify event fd 7, 0x18461b0, event 1
I0714 14:35:25.453562    8265 init_comm.go:68] [console] pid 331 exit normally, status 0
I0714 14:35:25.459454    8265 init_comm.go:68] [console] exec pid 332, pid 331
I0714 14:35:25.461177    8265 init_comm.go:68] [console] can not find exec whose pid is 331
I0714 14:35:25.463375    8265 init_comm.go:68] [console] hyper_loop epoll_wait -1
I0714 14:35:25.467835    8265 init_comm.go:68] [console] can not find container test
I0714 14:35:25.477191    8265 init_comm.go:68] [console] enter container ns failed
I0714 14:35:25.481876    8265 init_comm.go:68] [console] pid 332 exit normally, status 125
I0714 14:35:25.485357    8265 init_comm.go:68] [console] exec pid 332, pid 332
I0714 14:35:25.488879    8265 init_comm.go:68] [console] hyper_handle_exec_exit exec exit pid 332, seq 3, container test
I0714 14:35:25.490419    8265 init_comm.go:68] [console] still have 3 user of exec
I0714 14:35:25.493908    8265 init_comm.go:68] [console] hyper_loop epoll_wait -1
I0714 14:35:25.497349    8265 init_comm.go:68] [console] hyper_loop epoll_wait 3
I0714 14:35:25.499015    8265 init_comm.go:68] [console] hyper_handle_event get event 8, de 0x18461b0, fd 7. ops 0x61b9c0
I0714 14:35:25.500690    8265 init_comm.go:68] [console] get epoll err of not epool in event
I0714 14:35:25.502264    8265 init_comm.go:68] [console] stdin_hup
I0714 14:35:25.504123    8265 init_comm.go:68] [console] pts_hup, seq 3
I0714 14:35:25.506653    8265 init_comm.go:68] [console] still have 2 user of exec
I0714 14:35:25.511390    8265 init_comm.go:68] [console] hyper_handle_event get event 16, de 0x18461e8, fd 8. ops 0x61b980
I0714 14:35:25.514843    8265 init_comm.go:68] [console] hyper_handle_event event EPOLLHUP, de 0x18461e8, fd 8, 0x61b980
I0714 14:35:25.518198    8265 init_comm.go:68] [console] stdout_hup
I0714 14:35:25.520115    8265 init_comm.go:68] [console] pts_hup, seq 3
I0714 14:35:25.523857    8265 init_comm.go:68] [console] still have 1 user of exec
I0714 14:35:25.527152    8265 init_comm.go:68] [console] hyper_handle_event get event 16, de 0x1846220, fd 10. ops 0x61b940
I0714 14:35:25.528816    8265 init_comm.go:68] [console] hyper_handle_event event EPOLLHUP, de 0x1846220, fd 10, 0x61b940
I0714 14:35:25.530722    8265 init_comm.go:68] [console] stderr_hup
I0714 14:35:25.532392    8265 init_comm.go:68] [console] pts_hup, seq 3
I0714 14:35:25.534152    8265 init_comm.go:68] [console] last user of exec exit, release
I0714 14:35:25.537564    8265 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61ba48, event 5
I0714 14:35:25.541036    8265 init_comm.go:68] [console] hyper_release_exec exit code 125
I0714 14:35:25.544592    8265 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0714 14:35:25.547744    8265 init_comm.go:68] [console] hyper_handle_event get event 4, de 0x61ba48, fd 4. ops 0x61b820
I0714 14:35:25.550239    8265 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, de 0x61ba48, fd 4, 0x61b820
I0714 14:35:25.555267    8265 init_comm.go:68] [console] hyper_modify_event modify event fd 4, 0x61ba48, event 1
I0714 14:35:25.314963    8265 events.go:54] write event log: {test start-process 2016-07-14 14:35:25.312487431 +0900 KST 100 0}
I0714 14:35:25.351909    8265 tty.go:99] tty: read 12/12 [length = 0]
I0714 14:35:25.560258    8265 tty.go:103] data length is 12
I0714 14:35:25.561862    8265 tty.go:160] session 3 closed by peer, close pty
I0714 14:35:25.564055    8265 tty.go:89] tty: trying to read 12 bytes
I0714 14:35:25.567443    8265 tty.go:99] tty: read 12/12 [length = 0]
I0714 14:35:25.570876    8265 tty.go:103] data length is 13
I0714 14:35:25.575633    8265 tty.go:89] tty: trying to read 1 bytes
I0714 14:35:25.577321    8265 tty.go:99] tty: read 13/13 [length = 13]
I0714 14:35:25.579639    8265 tty.go:167] session 3, exit code 125
I0714 14:35:25.583033    8265 context.go:206] can not found container whose session is %!s(uint64=3)
I0714 14:35:25.584703    8265 context.go:178] found exec 100 whose session is 3
I0714 14:35:25.586383    8265 tty.go:239] Close tty 
I0714 14:35:25.588014    8265 tty.go:89] tty: trying to read 12 bytes
I0714 14:35:25.331939    8265 init_comm.go:106] read 8/8 [length = 0]
I0714 14:35:25.592076    8265 init_comm.go:110] data length is 12
I0714 14:35:25.595655    8265 init_comm.go:96] trying to read 4 bytes
I0714 14:35:25.599316    8265 init_comm.go:106] read 12/12 [length = 12]
I0714 14:35:25.601665    8265 init_comm.go:96] trying to read 8 bytes
I0714 14:35:25.607519    8265 init_comm.go:106] read 8/8 [length = 0]
I0714 14:35:25.609556    8265 init_comm.go:110] data length is 12
I0714 14:35:25.612815    8265 init_comm.go:96] trying to read 4 bytes
I0714 14:35:25.615989    8265 init_comm.go:106] read 12/12 [length = 12]
I0714 14:35:25.618040    8265 init_comm.go:96] trying to read 8 bytes
I0714 14:35:25.620250    8265 init_comm.go:106] read 8/8 [length = 0]
I0714 14:35:25.624056    8265 init_comm.go:110] data length is 8
I0714 14:35:25.628765    8265 init_comm.go:96] trying to read 8 bytes
I0714 14:35:25.601841    8265 init_comm.go:190] got cmd:14
I0714 14:35:25.635490    8265 init_comm.go:253] get command NEXT
I0714 14:35:25.640592    8265 init_comm.go:256] send 112, receive 8
I0714 14:35:25.645285    8265 init_comm.go:190] got cmd:14
I0714 14:35:25.648517    8265 init_comm.go:253] get command NEXT
I0714 14:35:25.650480    8265 init_comm.go:256] send 112, receive 112
I0714 14:35:25.652509    8265 init_comm.go:190] got cmd:9
I0714 14:35:25.655812    8265 init_comm.go:209] ack got, clear pong timer
I0714 14:35:25.655997    8265 hypervisor.go:29] vm vm-WrgZYYomSG: main event loop got message 34(GENERIC_OPERATION)
I0714 14:35:25.662213    8265 vm_states.go:296] handle GenericOperation(StartStdin) on state(RUNNING)
I0714 14:35:25.666886    8265 tty.go:36] tty is closed
I0714 14:35:25.670626    8265 tty.go:36] tty is closed
I0714 14:35:25.673808    8265 events.go:121] notifySubscribers: {test exit 2016-07-14 14:35:25.67380183 +0900 KST 100 -1}
I0714 14:35:25.676314    8265 events.go:54] write event log: {test exit 2016-07-14 14:35:25.67380183 +0900 KST 100 -1}
I0714 14:35:25.676337    8265 supervisor.go:115] reap container test processId 100
laijs commented 8 years ago

I0714 14:35:25.467835 8265 init_comm.go:68] [console] can not find container test

could you give me some earlier log?

keyolk commented 8 years ago

well I'm not sure which one you want here I reproduce it again and below is some what earlier 

I0714 15:59:23.359355   25190 init_comm.go:68] [console] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
I0714 15:59:23.363623   25190 init_comm.go:68] [console] Warning: Processor Platform Limit event detected, but not handled.
I0714 15:59:23.367054   25190 init_comm.go:68] [console] Consider compiling CPUfreq support into your kernel.
I0714 15:59:23.373328   25190 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 10
I0714 15:59:23.378751   25190 init_comm.go:68] [console] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver
I0714 15:59:23.383640   25190 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
I0714 15:59:23.388494   25190 init_comm.go:68] [console] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
I0714 15:59:23.391948   25190 init_comm.go:68] [console] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
I0714 15:59:23.396589   25190 init_comm.go:68] [console] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
I0714 15:59:23.399175   25190 init_comm.go:68] [console] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
I0714 15:59:23.404160   25190 init_comm.go:68] [console] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
I0714 15:59:23.419484   25190 init_comm.go:68] [console] brd: module loaded
I0714 15:59:23.422900   25190 init_comm.go:68] [console] loop: module loaded
I0714 15:59:23.427433   25190 init_comm.go:68] [console] scsi host0: Virtio SCSI HBA
I0714 15:59:23.435638   25190 init_comm.go:68] [console] rtc_cmos 00:00: RTC can wake from S4
I0714 15:59:23.439307   25190 init_comm.go:68] [console] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
I0714 15:59:23.442797   25190 init_comm.go:68] [console] rtc_cmos 00:00: alarms up to one day, y3k, 114 bytes nvram
I0714 15:59:23.447491   25190 init_comm.go:68] [console] Initializing XFRM netlink socket
I0714 15:59:23.450911   25190 init_comm.go:68] [console] NET: Registered protocol family 10
I0714 15:59:23.454476   25190 init_comm.go:68] [console] NET: Registered protocol family 17
I0714 15:59:23.458241   25190 init_comm.go:68] [console] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this.
I0714 15:59:23.463065   25190 init_comm.go:68] [console] Bridge firewalling registered
I0714 15:59:23.466575   25190 init_comm.go:68] [console] 9pnet: Installing 9P2000 support
I0714 15:59:23.471228   25190 init_comm.go:68] [console] registered taskstats version 1
I0714 15:59:23.476486   25190 init_comm.go:68] [console] rtc_cmos 00:00: setting system clock to 2016-07-14 06:59:22 UTC (1468479562)
I0714 15:59:23.480093   25190 init_comm.go:68] [console] Freeing unused kernel memory: 876K (ffffffff81690000 - ffffffff8176b000)
I0714 15:59:23.484800   25190 init_comm.go:68] [console] create directory /sys
I0714 15:59:23.489371   25190 init_comm.go:68] [console] create directory /sbin
I0714 15:59:23.492887   25190 init_comm.go:68] [console] create directory /proc
I0714 15:59:23.496478   25190 init_comm.go:68] [console] uptime 0.30 0.01
I0714 15:59:23.500304   25190 init_comm.go:68] [console] 
I0714 15:59:23.505021   25190 init_comm.go:68] [console] create directory /dev/pts
I0714 15:59:23.508522   25190 init_comm.go:68] [console] open hyper channel /dev/vport0p1
I0714 15:59:23.512064   25190 init_comm.go:68] [console] send ready message
I0714 15:59:23.516685   25190 init_comm.go:68] [console] hyper send type 8, len 0
I0714 15:59:23.521036   25190 init_comm.go:68] [console] channel sh.hyper.channel.1, directory sh.hyper.channel.0
I0714 15:59:23.525819   25190 init_comm.go:68] [console] 
I0714 15:59:23.530637   25190 init_comm.go:68] [console] open hyper channel /dev/vport0p2
I0714 15:59:23.535203   25190 init_comm.go:68] [console] hyper_init_event hyper channel event 0x61ba80, ops 0x61b860, fd 3
I0714 15:59:23.538630   25190 init_comm.go:68] [console] hyper_add_event add event fd 3, 0x61b860random: busybox urandom read with 11 bits of entropy available
I0714 15:59:23.542521   25190 init_comm.go:68] [console] 
I0714 15:59:23.547609   25190 init_comm.go:68] [console] hyper_init_event hyper ttyfd event 0x61ba48, ops 0x61b820, fd 4
I0714 15:59:23.551178   25190 init_comm.go:68] [console] hyper_add_event add event fd 4, 0x61b820
I0714 15:59:23.554738   25190 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0714 15:59:23.558306   25190 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x61ba80, fd 3. ops 0x61b860
I0714 15:59:23.561751   25190 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x61ba80, fd 3, 0x61b860
I0714 15:59:23.564014   25190 init_comm.go:68] [console] hyper_event_read
I0714 15:59:23.568947   25190 init_comm.go:68] [console] already read 8 bytes data
I0714 15:59:23.573857   25190 init_comm.go:68] [console] hyper send type 14, len 4
I0714 15:59:23.578496   25190 init_comm.go:68] [console] get length 67
I0714 15:59:23.583697   25190 init_comm.go:68] [console] read 59 bytes data, total data 67
I0714 15:59:23.587558   25190 init_comm.go:68] [console] hyper send type 14, len 4
I0714 15:59:23.592440   25190 init_comm.go:68] [console] 0 0 0 1 0 0 0 43 7b 22 68 6f 73 74 6e 61 6d 65 22 3a 22 73 68 65 6c 6c 22 2c 22 63 6f 6e 74 61 69 6e 65 72 73 22 3a 5b 5d 2c 22 73 68 61 72 65 44 69 72 22
 3a 22 73 68 61 72 65 5f 64 69 72 22 7d
I0714 15:59:23.596170   25190 init_comm.go:68] [console]  hyper_channel_handle, type 1, len 67
I0714 15:59:23.599603   25190 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"shell","containers":[],"shareDir":"share_dir"}., len 59
I0714 15:59:23.604331   25190 init_comm.go:68] [console] call hyper_start_pod, json {"hostname":"shell","containers":[],"shareDir":"share_dir"}., len 59
I0714 15:59:23.608829   25190 init_comm.go:68] [console] jsmn parse successed, n is 7
I0714 15:59:23.612490   25190 init_comm.go:68] [console] token 0, type is 1, size is 3
I0714 15:59:23.616119   25190 init_comm.go:68] [console] token 1, type is 3, size is 1
I0714 15:59:23.620958   25190 init_comm.go:68] [console] hostname is shell
I0714 15:59:23.625634   25190 init_comm.go:68] [console] token 3, type is 3, size is 1
I0714 15:59:23.630590   25190 init_comm.go:68] [console] container count 0
I0714 15:59:23.633213   25190 init_comm.go:68] [console] token 5, type is 3, size is 1
I0714 15:59:23.637950   25190 init_comm.go:68] [console] share tag is share_dir
I0714 15:59:23.641646   25190 init_comm.go:68] [console] create directory /tmp
I0714 15:59:23.645256   25190 init_comm.go:68] [console] create directory /tmp/hyper
I0714 15:59:23.650978   25190 init_comm.go:68] [console] create directory /tmp/hyper/proc
I0714 15:59:23.653343   25190 init_comm.go:68] [console] finish rescan
I0714 15:59:23.656892   25190 init_comm.go:68] [console] create directory /tmp/hyper/shared
I0714 15:59:23.661751   25190 init_comm.go:68] [console] pod init pid 327
I0714 15:59:23.665360   25190 init_comm.go:68] [console] hyper send type 8, len 0
I0714 15:59:23.670335   25190 init_comm.go:68] [console] uptime 0.45 0.05
I0714 15:59:23.672999   25190 init_comm.go:68] [console] 
I0714 15:59:23.676532   25190 init_comm.go:68] [console] hyper send type 9, len 0
I0714 15:59:23.681408   25190 init_comm.go:68] [console] pid 326 exit normally, status 0
I0714 15:59:23.684973   25190 init_comm.go:68] [console] can not find exec whose pid is 326
I0714 15:59:23.688435   25190 init_comm.go:68] [console] hyper_loop epoll_wait -1
I0714 15:59:23.692028   25190 init_comm.go:68] [console] tsc: Refined TSC clocksource calibration: 2394.476 MHz
I0714 15:59:23.695595   25190 init_comm.go:68] [console] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2283d51e853, max_idle_ns: 440795296375 ns
I0714 15:59:33.080128   25190 process.go:33] process setupIO: stdin /tmp/ctr-253383135/stdin, stdout /tmp/ctr-253383135/stdout, stderr /tmp/ctr-253383135/stderr
I0714 15:59:33.083776   25190 process.go:61] process setupIO() success
I0714 15:59:33.088428   25190 events.go:121] notifySubscribers: {test start-process 2016-07-14 15:59:33.088415388 +0900 KST 100 0}
I0714 15:59:33.091241   25190 hypervisor.go:29] vm vm-SdzMbDKNea: main event loop got message 34(GENERIC_OPERATION)
I0714 15:59:33.096429   25190 vm_states.go:296] handle GenericOperation(AddProcess) on state(RUNNING)
I0714 15:59:33.101641   25190 init_comm.go:190] got cmd:6
I0714 15:59:33.105477   25190 init_comm.go:281] send command 6 to init, payload: '{"container":"test","process":{"terminal":false,"stdio":1,"stderr":2,"args":["ps","aux"],"workdir":"/"}}'.
I0714 15:59:33.109335   25190 init_comm.go:294] write 112 to init, payload: '\200\200\200^F\200\200\200p{"container":"test","process":{"terminal":false,"stdio":1,"stderr":2,"args":["ps","aux"],"workdir":"/"}}'.
I0714 15:59:33.121424   25190 init_comm.go:299] message sent, set pong timer
I0714 15:59:33.110069   25190 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0714 15:59:33.131604   25190 init_comm.go:68] [console] hyper_handle_event get event 1, de 0x61ba80, fd 3. ops 0x61b860
I0714 15:59:33.136367   25190 init_comm.go:68] [console] hyper_handle_event event EPOLLIN, de 0x61ba80, fd 3, 0x61b860
I0714 15:59:33.141186   25190 init_comm.go:68] [console] hyper_event_read
I0714 15:59:33.145790   25190 init_comm.go:68] [console] already read 8 bytes data
I0714 15:59:33.148449   25190 init_comm.go:68] [console] hyper send type 14, len 4
I0714 15:59:33.152218   25190 init_comm.go:68] [console] get length 112
I0714 15:59:33.156911   25190 init_comm.go:68] [console] read 104 bytes data, total data 112
I0714 15:59:33.160577   25190 init_comm.go:68] [console] hyper send type 14, len 4
I0714 15:59:33.164157   25190 init_comm.go:68] [console] 0 0 0 6 0 0 0 70 7b 22 63 6f 6e 74 61 69 6e 65 72 22 3a 22 74 65 73 74 22 2c 22 70 72 6f 63 65 73 73 22 3a 7b 22 74 65 72 6d 69 6e 61 6c 22 3a 66 61 6c 73
 65 2c 22 73 74 64 69 6f 22 3a 31 2c 22 73 74 64 65 72 72 22 3a 32 2c 22 61 72 67 73 22 3a 5b 22 70 73 22 2c 22 61 75 78 22 5d 2c 22 77 6f 72 6b 64 69 72 22 3a 22 2f 22 7d 7d 
I0714 15:59:33.168810   25190 init_comm.go:68] [console]  hyper_channel_handle, type 6, len 112
I0714 15:59:33.173816   25190 init_comm.go:68] [console] call hyper_exec_cmd, json {"container":"test","process":{"terminal":false,"stdio":1,"stderr":2,"args":["ps","aux"],"workdir":"/"}} , len 104
I0714 15:59:33.177659   25190 init_comm.go:68] [console] jsmn parse failed, n is -1
I0714 15:59:33.182591   25190 init_comm.go:68] [console] get container test
I0714 15:59:33.187563   25190 init_comm.go:68] [console] 1 name terminal
I0714 15:59:33.192766   25190 init_comm.go:68] [console] container doesn't use terminal
I0714 15:59:33.196832   25190 init_comm.go:68] [console] 3 name stdio
I0714 15:59:33.201996   25190 init_comm.go:68] [console] container seq 1
I0714 15:59:33.205570   25190 init_comm.go:68] [console] 5 name stderr
I0714 15:59:33.210258   25190 init_comm.go:68] [console] container stderr seq 2
I0714 15:59:33.215867   25190 init_comm.go:68] [console] 7 name args
I0714 15:59:33.219602   25190 init_comm.go:68] [console] container init arg 0 ps
I0714 15:59:33.223456   25190 init_comm.go:68] [console] container init arg 1 aux
I0714 15:59:33.227212   25190 init_comm.go:68] [console] 11 name workdir
I0714 15:59:33.232162   25190 init_comm.go:68] [console] container workdir /
I0714 15:59:33.237000   25190 init_comm.go:68] [console] hyper_init_event container pts event 0x15ee300, ops 0x61b9c0, fd 7
I0714 15:59:33.242206   25190 init_comm.go:68] [console] hyper_add_event add event fd 7, 0x61b9c0
I0714 15:59:33.246293   25190 init_comm.go:68] [console] hyper_add_event add event fd 8, 0x61b980
I0714 15:59:33.251314   25190 init_comm.go:68] [console] hyper_add_event add event fd 10, 0x61b940
I0714 15:59:33.256767   25190 init_comm.go:68] [console] do_exec_cmd pid 329
I0714 15:59:33.262484   25190 init_comm.go:68] [console] create exec cmd ps pid 330,ref 4
I0714 15:59:33.267785   25190 init_comm.go:68] [console] hyper send type 330, len 0
I0714 15:59:33.272594   25190 init_comm.go:68] [console] hyper_run_process get ready message 330
I0714 15:59:33.277789   25190 init_comm.go:68] [console] hyper send type 9, len 0
I0714 15:59:33.281327   25190 init_comm.go:68] [console] hyper_loop epoll_wait 1
I0714 15:59:33.286290   25190 init_comm.go:68] [console] hyper_handle_event get event 4, de 0x15ee300, fd 7. ops 0x61b9c0
I0714 15:59:33.291284   25190 init_comm.go:68] [console] hyper_handle_event event EPOLLOUT, de 0x15ee300, fd 7, 0x61b9c0
I0714 15:59:33.296314   25190 init_comm.go:68] [console] write_to_stdin, seq 1
I0714 15:59:33.301129   25190 init_comm.go:68] [console] hyper_modify_event modify event fd 7, 0x15ee300, event 1
I0714 15:59:33.305991   25190 init_comm.go:68] [console] pid 329 exit normally, status 0
I0714 15:59:33.309588   25190 init_comm.go:68] [console] exec pid 330, pid 329
I0714 15:59:33.314384   25190 init_comm.go:68] [console] can not find exec whose pid is 329
I0714 15:59:33.316764   25190 init_comm.go:68] [console] hyper_loop epoll_wait -1
I0714 15:59:33.321548   25190 init_comm.go:68] [console] can not find container test
laijs commented 8 years ago

it show that the container hasn't created in the hyperstart when exec

could you add --debug to runv-containerd for more logs

keyolk commented 8 years ago

@laijs already puted the --debug option. and when I check it ctr --address=$CONTAINERD_SOCK containers I can see below output

ID PATH STATUS PROCESSES test /home/keyolk/workspace/hyper running init

is there some options to get more log ?

laijs commented 8 years ago 
Making all in build
make: relocation error: libm.so.6: symbol __get_cpu_features, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference
make[1]: *** [Makefile:352: all-recursive] Error 1
make[1]: Leaving directory

it seems the check for libm.so was called earlier than hyper-initrd-build-script, could you give me your build/Makefile (post it on gist)?

keyolk commented 8 years ago

@laijs I uploaded the file here

keyolk commented 8 years ago

@gao-feng @laijs Is there anything I can check ?

I use 0.6.0 version of runv, hyperd, hyperstart

and I found somthing strange again see below

$ pwd 
/home/keyolk/workspace/projects/container/src/github.com/hyperhq/hyperstart

$ cd build
/usr/bin/python2: relocation error: libm.so.6: symbol __get_cpu_features, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference
/usr/bin/python2: relocation error: libm.so.6: symbol __get_cpu_features, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference
ls
busybox     hyper-initrd.img  kernel         kernel_patch  Makefile     Makefile.in     modules.tar
Dockerfile  iptables          kernel_config  libm.so.6     Makefile.am  make-initrd.sh  vbox
/usr/bin/python2: relocation error: libm.so.6: symbol __get_cpu_features, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference
/usr/bin/python2: relocation error: libm.so.6: symbol __get_cpu_features, version GLIBC_PRIVATE not defined in file libc.so.6 with link time reference

like above it put error even I just cd to the directory : (

laijs commented 8 years ago

@keyolk does the problem still exist?

keyolk commented 8 years ago

@laijs Sorry to late response. the problem still exist.

laijs commented 7 years ago

@keyolk does the problem still exist?