Skip to content

create Failed : 500 INTERNAL SERVER ERROR #145

Open
Open
create Failed : 500 INTERNAL SERVER ERROR#145

Description

@fabianlv
fabianlv
opened on Jan 15, 2019

[root@ceph1 ceph]# gwcli
/iscsi-target> ls
o- iscsi-target .................................................................... [Targets: 0]
/iscsi-target> create iqn.2003-01.com.ceph.iscsi-gw:iscsi-igw
ok
/iscsi-target> cd iqn.2003-01.com.ceph.iscsi-gw:iscsi-igw/gateways
/iscsi-target...-igw/gateways> create ceph1 192.168.80.11
Adding gateway, sync'ing 0 disk(s) and 0 client(s)
ok
/iscsi-target...-igw/gateways> create ceph2 192.168.80.12
Adding gateway, sync'ing 0 disk(s) and 0 client(s)
ok
/iscsi-target...-igw/gateways> cd /disks
/disks> create pool=rbd image=disk01 size=256M
Failed : 500 INTERNAL SERVER ERROR
/disks> ls
o- disks ......................................................................... [0b, Disks: 0]
/disks> create pool=rbd image=disk01 size=1G
Failed : 500 INTERNAL SERVER ERROR
/disks> create pool=rbd image=disk01 size=1G
Failed : 500 INTERNAL SERVER ERROR
/disks> create pool=rbd image=disk02 size=256M
Failed : 500 INTERNAL SERVER ERROR

rbd-target-api.log:
2019-01-15 17:57:52,569 DEBUG [rbd-target-api:599:disk()] - this host is ceph1
2019-01-15 17:57:52,569 DEBUG [rbd-target-api:614:disk()] - All gateways: [u'ceph1', u'ceph2']
2019-01-15 17:57:52,569 DEBUG [rbd-target-api:628:disk()] - Other gateways: [u'ceph2']
2019-01-15 17:57:52,573 INFO [_internal.py:87:_log()] - 127.0.0.1 - - [15/Jan/2019 17:57:52] "GET /api/config HTTP/1.1" 200 -
2019-01-15 17:57:52,605 INFO [_internal.py:87:_log()] - 127.0.0.1 - - [15/Jan/2019 17:57:52] "GET /api/_ping HTTP/1.1" 200 -
2019-01-15 17:57:52,610 DEBUG [rbd-target-api:1682:call_api()] - gateway update order is 127.0.0.1,ceph2
2019-01-15 17:57:52,610 DEBUG [rbd-target-api:1685:call_api()] - processing GW '127.0.0.1'
2019-01-15 17:57:52,624 DEBUG [common.py:123:_open_ioctx()] - (_open_ioctx) Opening connection to rbd pool
2019-01-15 17:57:52,625 DEBUG [common.py:130:_open_ioctx()] - (_open_ioctx) connection opened
2019-01-15 17:57:52,629 DEBUG [common.py:171:init_config()] - (init_config) using pre existing config object
2019-01-15 17:57:52,629 DEBUG [common.py:123:_open_ioctx()] - (_open_ioctx) Opening connection to rbd pool
2019-01-15 17:57:52,629 DEBUG [common.py:130:_open_ioctx()] - (_open_ioctx) connection opened
2019-01-15 17:57:52,630 DEBUG [common.py:102:_read_config_object()] - _read_config_object reading the config object
2019-01-15 17:57:52,631 DEBUG [common.py:152:_get_ceph_config()] - (_get_rbd_config) config object contains '{
"clients": {},
"created": "2019/01/15 08:12:13",
"disks": {},
"epoch": 7,
"gateways": {
"ceph1": {
"active_luns": 0,
"created": "2019/01/15 09:53:45",
"gateway_ip_list": [
"192.168.80.11",
"192.168.80.12"
],
"inactive_portal_ips": [
"192.168.80.12"
],
"iqn": "iqn.2003-01.com.ceph.iscsi-gw:iscsi-igw",
"portal_ip_address": "192.168.80.11",
"tpgs": 2,
"updated": "2019/01/15 09:53:50"
},
"ceph2": {
"active_luns": 0,
"created": "2019/01/15 09:53:50",
"gateway_ip_list": [
"192.168.80.11",
"192.168.80.12"
],
"inactive_portal_ips": [
"192.168.80.11"
],
"iqn": "iqn.2003-01.com.ceph.iscsi-gw:iscsi-igw",
"portal_ip_address": "192.168.80.12",
"tpgs": 2,
"updated": "2019/01/15 09:53:50"
},
"created": "2019/01/15 09:53:30",
"ip_list": [
"192.168.80.11",
"192.168.80.12"
],
"iqn": "iqn.2003-01.com.ceph.iscsi-gw:iscsi-igw"
},
"groups": {},
"updated": "2019/01/15 09:53:50",
"version": 3
}'
2019-01-15 17:57:52,668 ERROR [rbd-target-api:729:_disk()] - TEST: ['owner', 'mode', 'pool', 'size']
2019-01-15 17:57:52,669 ERROR [rbd-target-api:730:_disk()] - TEST: None
2019-01-15 17:57:52,669 ERROR [rbd-target-api:732:_disk()] - TEST: 8
2019-01-15 17:57:52,669 DEBUG [lun.py:346:allocate()] - LUN.allocate starting, listing rbd devices
2019-01-15 17:57:52,688 DEBUG [lun.py:349:allocate()] - rados pool 'rbd' contains the following - [u'disk01']
2019-01-15 17:57:52,689 DEBUG [lun.py:354:allocate()] - Hostname Check - this host is ceph1, target host for allocations is ceph1
2019-01-15 17:57:52,754 DEBUG [common.py:271:add_item()] - (Config.add_item) config updated to {u'updated': u'2019/01/15 09:53:50', u'disks': {'rbd.disk01': {'created': '2019/01/15 09:57:52'}}, u'created': u'2019/01/15 08:12:13', u'clients': {}, u'epoch': 7, u'version': 3, u'gateways': {u'ceph1': {u'gateway_ip_list': [u'192.168.80.11', u'192.168.80.12'], u'active_luns': 0, u'created': u'2019/01/15 09:53:45', u'updated': u'2019/01/15 09:53:50', u'iqn': u'iqn.2003-01.com.ceph.iscsi-gw:iscsi-igw', u'inactive_portal_ips': [u'192.168.80.12'], u'portal_ip_address': u'192.168.80.11', u'tpgs': 2}, u'iqn': u'iqn.2003-01.com.ceph.iscsi-gw:iscsi-igw', u'ceph2': {u'gateway_ip_list': [u'192.168.80.11', u'192.168.80.12'], u'active_luns': 0, u'created': u'2019/01/15 09:53:50', u'updated': u'2019/01/15 09:53:50', u'iqn': u'iqn.2003-01.com.ceph.iscsi-gw:iscsi-igw', u'inactive_portal_ips': [u'192.168.80.11'], u'portal_ip_address': u'192.168.80.12', u'tpgs': 2}, u'ip_list': [u'192.168.80.11', u'192.168.80.12'], u'created': u'2019/01/15 09:53:30'}, u'groups': {}}
2019-01-15 17:57:52,754 DEBUG [lun.py:409:allocate()] - Check the rbd image size matches the request
2019-01-15 17:57:52,802 DEBUG [lun.py:430:allocate()] - rbd image rbd.disk01 size matches the configuration file request
2019-01-15 17:57:52,802 DEBUG [lun.py:432:allocate()] - Begin processing LIO mapping
2019-01-15 17:57:52,802 INFO [lun.py:626:add_dev_to_lio()] - (LUN.add_dev_to_lio) Adding image 'rbd.disk01' to LIO
2019-01-15 17:57:52,802 DEBUG [lun.py:636:add_dev_to_lio()] - control="max_data_area_mb=8"
2019-01-15 17:57:52,809 INFO [_internal.py:87:_log()] - 127.0.0.1 - - [15/Jan/2019 17:57:52] "PUT /api/_disk/rbd.disk01 HTTP/1.1" 500 -
2019-01-15 17:57:52,810 ERROR [rbd-target-api:1706:call_api()] - _disk change on 127.0.0.1 failed with 500
2019-01-15 17:57:52,820 INFO [_internal.py:87:_log()] - 127.0.0.1 - - [15/Jan/2019 17:57:52] "PUT /api/disk/rbd.disk01 HTTP/1.1" 500 -
2019-01-15 17:57:53,014 INFO [_internal.py:87:_log()] - 192.168.80.12 - - [15/Jan/2019 17:57:53] "GET /api/_ping HTTP/1.1" 200 -
2019-01-15 17:58:03,015 INFO [_internal.py:87:_log()] - 192.168.80.12 - - [15/Jan/2019 17:58:03] "GET /api/_ping HTTP/1.1" 200 -
2019-01-15 17:58:13,020 INFO [_internal.py:87:_log()] - 192.168.80.12 - - [15/Jan/2019 17:58:13] "GET /api/_ping HTTP/1.1" 200 -

my ceph version:ceph version 12.2.10
os :CentOS Linux release 7.6.1810 (Core)
kernel:Linux ceph1 3.10.0-957.el7.x86_64 #1

Activity

  1. dillaman commented on Jan 15, 2019

    @dillaman
    dillaman
    on Jan 15, 2019

    Do you have tcmu-runner installed and running?

  2. fabianlv commented on Jan 17, 2019

    @fabianlv
    fabianlv
    on Jan 17, 2019
    Author

    Do you have tcmu-runner installed and running?

    how to detect tcmu-runner is running?

  3. fabianlv commented on Jan 17, 2019

    @fabianlv
    fabianlv
    on Jan 17, 2019
    Author

    Do you have tcmu-runner installed and running?

    [root@ceph1 ~]# ps -ef|grep tcmu-run
    root 9668 1 0 15:35 ? 00:00:00 /usr/bin/tcmu-runner
    root 20155 20137 0 15:37 pts/0 00:00:00 grep --color=auto tcmu-run

  4. mikechristie commented on Jan 17, 2019

    @mikechristie
    mikechristie
    on Jan 17, 2019
    Contributor

    Could you include the /var/log/messages and /var/log/tcmu-runner/tcmu-runner.log when you run the command so we can see what error is being reported.

    Also what version of tcmu-runner and kernel are you using?

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions